#!/usr/local/cdat/bin/python
"""
xrpubd.py

This program is a simple XML/RPC server that runs as a daemon to
provide services to ezpub.
"""
import glob
import grp
import logging, logging.handlers
import os
import pdb
import pexpect
import pwd
import re
import shutil
import signal
import socket
import stat
import subprocess
import sys
import tempfile
import time
import traceback as tb
import urllib2
import unittest

from daemon import Daemon
from ezp_util import contents, get_reqdir_name, scigest_home, has_java_exception
from optparse import *
from SimpleXMLRPCServer import SimpleXMLRPCServer
from SimpleXMLRPCServer import SimpleXMLRPCRequestHandler
from SocketServer import *

HOST = socket.gethostname()
PORT = 40001
LANDING_PAD = '/tmp/esg/lpad'
LOGDIR = '/tmp/esg/pubd'
LOGFILE = '%s/xrpubd.log' % LOGDIR
ESG_DATAROOT = '/esg/data'
THREDDS_ROOT = '/esg/content/thredds/esgcet'

# ---------------------------------------------------------------------------
def main(argv):
    """
    Startup/shutdown code for the daemon.
    """
    p = OptionParser()
    p.add_option('-d', '--debug',
                 action='store_true', default=False, dest='debug',
                 help='run under the debugger')
    p.add_option('-t', '--test',
                 action='store_true', default=False, dest='test',
                 help='run the tests')
    p.add_option('-v', '--verbose',
                 action='store_true', default=False, dest='verbose',
                 help='increase verbosity')
    p.add_option('-q', '--quiet',
                 action='store_true', default=False, dest='quiet',
                 help='be quiet')
    (o, a) = p.parse_args(argv)
    
    if o.debug: pdb.set_trace()

    if 0 != os.getuid():
        raise StandardError("You need to be root to run this.")
    
    if o.test:
        sys.argv[1:] = []
        if o.verbose: sys.argv.append('-v')
        if o.quiet: sys.argv.append('-q')
        unittest.main()
        
    assume_identity(user='tomcat', group='tomcat')
    perm_checks()
    
    daemon = xrpubd('/tmp/esg/pubd/xrpubd.pid', stdout='/tmp/esg/pubd/xrpubd.out')
    if len(a) != 2:
        print "usage: %s start|stop|restart" % sys.argv[0]
        sys.exit(2)
        
    if 'start' == a[1]:
        log("xrpubd starting up")
        daemon.start()
    elif 'stop' == a[1]:
        log("xrpubd shutting down")
        daemon.stop()
    elif 'restart' == a[1]:
        daemon.restart()
    else:
        log("Unknown conmmand: '%s'" % a[1])
        sys.exit(2)
    
# ---------------------------------------------------------------------------
class xrpub_handler(SimpleXMLRPCRequestHandler):
    """
    xrpub-specific handler restricted to a particular URL path
    """
    rpc_paths = ('/RPC2',)

# ---------------------------------------------------------------------------
# This call contains the payload functions the client wants to call.
class xrpubd_callables:
    """
    This class contains the service entry points that the client can
    call. By putting the service routines in a class like this, we
    only need one register call to set up our services.
    """

    # -----------------------------------------------------------------------
    def copy_data(self, username, src, dest):
        """
        Copy a data file from the user's request directory to the data area.

        !@! This routine will become obsolete and go away when we
        change ezpub to stage data directly to the data area.
        """
        try:
            log("--- %s(%s, %s) called by %s" % (my_name(), src, dest, username))
            if not os.path.exists(src):
                return log("FAIL: source file '%s' not found" % src)

            # sdir = os.path.dirname(src)
            # if not src.startswith(LANDING_PAD):
            #     return log("FAIL: Can only copy from %s" % LANDING_PAD)
            
            ddir = os.path.dirname(dest)
            if not ddir.startswith(ESG_DATAROOT):
                return log("FAIL: Can only copy into %s" % ESG_DATAROOT)

            if not os.path.exists(ddir):
                try:
                    os.makedirs(ddir)
                except Exception, e:
                    return log("FAIL: os.makedirs(%s) fails (%s)"
                               % (ddir, str(e)))

            try:
                shutil.copy(src, dest)
            except Exception, e:
                return log("FAIL: shutil.copy(%s, %s) fails (%s)"
                           % (src, dest, str(e)))

            return("OK")

        except Exception, e:
            return log("FAIL: %s fails (%s)" % (my_name(), str(e)))

    # -----------------------------------------------------------------------
    def list_reqdirs(self, username):
        """
        Return a list of the user's request directories.
        """
        try:
            log("--- %s(%s) called by %s" % (my_name(), username, username))
            rval = []
            rqdl = glob.glob("%s/%s*" % (LANDING_PAD, username))
            rqdl.sort()
            rqdl.reverse()
            for rqd in rqdl:
                rval.append(os.path.basename(rqd))
                xmll = contents("%s/catalog.txt" % rqd, False)
                rval.extend(["   %s" % x.strip() for x in xmll])
            return rval
        
        except Exception, e:
            return log("FAIL: %s fails (%s)" % (my_name(), str(e)))
        
    # -----------------------------------------------------------------------
    def solr_attach_metadata(self, username, where):
        """
        Run MetadataDriver to ingest external metadata into Solr.
        """
        try:
            log("--- %s() called by %s" % (my_name(), username))

            cfgset('data.src', where)

            os.environ['CLASSPATH'] = "%s/build" % scigest_home() \
                                      + ":%s/resources" % scigest_home()
            log("CLASSPATH = '%s'" % os.getenv('CLASSPATH'))
            cmd = ["/usr/local/java/bin/java",
                   "-Djava.ext.dirs=%s/lib/fetched/runtime" % scigest_home(),
                   "scigest.metadata.MetadataDriver"]
            log("running '%s'" % " ".join(cmd))
            proc = subprocess.Popen(cmd,
                                    stdout=subprocess.PIPE,
                                    stderr=subprocess.STDOUT)
            result = "".join(proc.stdout.readlines())
            for line in result.split("\n"):
                log(line)
            log("back from calling MetadataDriver")

            if has_java_exception(result):
                return log("FAIL: Java threw exception")
            
            return("OK")
        
        except Exception, e:
            return log("FAIL: %s fails (%s)" % (my_name(), str(e)))
 
    # -----------------------------------------------------------------------
    def solr_publish(self, username, ingest=True):
        """
        Run PublishingServiceMain to ingest the THREDDS catalog into Solr.
        """
        try:
            log("--- %s(%s) called by %s" % (my_name(), str(ingest), username))

            webinf = "/usr/local/tomcat/webapps/esg-search/WEB-INF"
            os.environ['CLASSPATH'] = "%s/classes" % webinf
            log("CLASSPATH = '%s'" % os.getenv('CLASSPATH'))
            cmd = ["/usr/local/java/bin/java",
                   "-Djava.ext.dirs=%s/lib" % webinf,
                   "-Dlog4j.configuration=%s/classes/log4j.xml" % webinf,
                   "esg.search.publish.impl.PublishingServiceMain",
                   "http://%s/thredds/esgcet/catalog.xml"
                       % socket.gethostname(),
                   "THREDDS",
                   str(ingest).lower()]
            log("running '%s'" % " ".join(cmd))
            proc = subprocess.Popen(cmd,
                                    stdout=subprocess.PIPE,
                                    stderr=subprocess.STDOUT)
            result = "".join(proc.stdout.readlines())
            for line in result.split("\n"):
                log(line)
            log("back from calling harvester")
                
            if has_java_exception(result):
                return log("FAIL: Java threw exception")
                
            return("OK")
                
        except Exception, e:
            return log("FAIL: %s fails (%s)" % (my_name(), str(e)))

    # -----------------------------------------------------------------------
    def solr_unpub_files(self, username, xmllist):
        """
        Ask Solr to unpublish a list of files.
        """
        try:
            log("--- %s(%s) called by %s" % (my_name(), str(xmllist), username))

            webinf = "/usr/local/tomcat/webapps/esg-search/WEB-INF"
            os.environ['CLASSPATH'] = "%s/classes" % webinf
            log("CLASSPATH = '%s'" % os.getenv('CLASSPATH'))
            for fname in xmllist:
                uri = "http://%s/thredds/esgcet/1/%s" % (socket.gethostname(),
                                                         os.path.basename(fname))
                cmd = ["/usr/local/java/bin/java",
                       "-Djava.ext.dirs=%s/lib" % webinf,
                       "-Dlog4j.configuration=%s/classes/log4j.xml" % webinf,
                       "esg.search.publish.impl.PublishingServiceMain",
                       uri, "THREDDS", "false"]

                log("running '%s'" % " ".join(cmd))
                proc = subprocess.Popen(cmd,
                                        stdout=subprocess.PIPE,
                                        stderr=subprocess.STDOUT)
                result = "".join(proc.stdout.readlines())
                for line in result.split("\n"):
                    log(line)
                log("back from calling harvester")

                if has_java_exception(result):
                    return log("FAIL: Java threw exception")

            return("OK")
                
        except Exception, e:
            return log("FAIL: %s fails (%s)" % (my_name(), str(e)))

    # -----------------------------------------------------------------------
    def solr_unpub_reqdir(self, username, reqdir):
        """
        Ask Solr to unpublish all the files listed in the reqdir's
        catalog.txt.
        """
        try:
            log("--- %s(%s) called by %s" % (my_name(), reqdir, username))

            webinf = "/usr/local/tomcat/webapps/esg-search/WEB-INF"
            os.environ['CLASSPATH'] = "%s/classes" % webinf
            log("CLASSPATH = '%s'" % os.getenv('CLASSPATH'))

            f = open("%s/%s/catalog.txt" % (LANDING_PAD, reqdir))
            for fname in f:
                fpath = "%s/1/%s" % (THREDDS_ROOT, fname.strip())
                uri = "http://%s/thredds/esgcet/1/%s" % (socket.gethostname(),
                                                         fname.strip())
                if os.path.exists(fpath):
                    cmd = ["/usr/local/java/bin/java",
                           "-Djava.ext.dirs=%s/lib" % webinf,
                           "-Dlnog4j.configuration=%s/classes/log4j.xml" % webinf,
                           "esg.search.publish.impl.PublishingServiceMain",
                           uri, "THREDDS", "false"]

                    log("running '%s'" % " ".join(cmd))
                    proc = subprocess.Popen(cmd,
                                            stdout=subprocess.PIPE,
                                            stderr=subprocess.STDOUT)
                    result = "".join(proc.stdout.readlines())
                    for line in result.split("\n"):
                        log(line)
                    log("back from calling harvester")

                    if has_java_exception(result):
                        return log("FAIL: Java threw exception")
                else:
                    log("%s does not exist" % fpath)
                    
            return("OK")
                
        except Exception, e:
            return log("FAIL: %s fails (%s)" % (my_name(), str(e)))

    # -----------------------------------------------------------------------
    def thredds_add_file(self, username, xmlfile):
        """
        Copy a THREDDS .xml file from the user's request directory
        into the THREDDS area.
        """
        try:
            log("--- %s(%s) called by %s" % (my_name(), xmlfile, username))
            try:
                dest = "%s/1/%s" % (THREDDS_ROOT, os.path.basename(xmlfile))

                # if not xmlfile.startswith("%s/%s" % (LANDING_PAD, username)):
                #     return log("FAIL: Can only copy from %s/%s.*"
                #                % (LANDING_PAD, username))

                shutil.copy(xmlfile, dest)
            except Exception, e:
                return log("FAIL: shutil.copy(%s, %s) fails (%s; %s = %d)"
                           % (xmlfile, dest, str(e), "os.getuid",
                              os.getuid()))

            return("OK")
            
        except Exception, e:
            return log("FAIL: %s fails (%s)" % (my_name(), str(e)))

    # -----------------------------------------------------------------------
    def thredds_reinit(self, username):
        """
        Reinitialize the THREDDS server.
        """
        try:
            log("--- %s() called by %s" % (my_name(), username))
            reinit_url = "https://localhost:443/thredds/admin/debug?" \
                         + "catalogs/reinit"
            reinit_ok = "reinit ok"
            reinit_err_url = "https://localhost:443/thredds/admin" \
                             + "/content/logs/catalogInit.log"
            reinit_err = "Catalog init"
            reinit_fatal = "**Fatal"
            tuser = "dnode_user"
            try:
                tpass = contents('/esg/config/.esgf_pass').strip()
            except:
                return log("FAIL: db password not known for host %s"
                           % socket.gethostname())
            
            result = ""
            try:
                result = auth_read_thredds(reinit_url, tuser, tpass)
            except Exception, e:
                msg = `e`
                if msg.find("maximum recursion depth") != -1:
                    return log("FAIL: bad password (%s)" % msg)
                else:
                    return log("FAIL: %s" % tb.format_exc())

            if result.find(reinit_ok) == -1:
                return log("FAIL: reinit THREDDS - '%s'" % result)

            result = auth_read_thredds(reinit_err_url, tuser, tpass)
            index = result.rfind(reinit_err)
            r2 = result[index:]
            findex = r2.find(reinit_fatal)
            if findex != -1:
                i2 = r2[findex:].find('\n')
                errmsg = r2[findex:findex+i2]
                return log("FAIL: reinit THREDDS - '%s'\n%s" % (errmsg,r2))

            return("OK")

        except:
            return log("FAIL: %s fails (%s)" % (my_name(), tb.format_exc()))

    # -----------------------------------------------------------------------
    def thredds_unpub_files(self, username, xml_list):
        """
        Unpublish the files in xml_list from THREDDS.
        """
        try:
            log("--- %s(%s) called by %s" % (my_name(), str(xml_list), username))
            try:
                catalog_txt = "/tmp/catalog.%s.%s.txt" % (username,
                                          time.strftime("%Y.%m%d.%H%M%S"))
                c = open(catalog_txt, "w")
                for filename in xml_list:
                    c.write(filename + "\n")
                c.close()

                self.thredds_xref(username, catalog_txt, False)
                rm_filelist(["%s/1/%s" % (THREDDS_ROOT, x) for x in xml_list])
                rm_filelist([catalog_txt])
                
            except Exception, e:
                return log("FAIL: %s(%s, %s) fails (%s; %s = %d)"
                           % (my_name(), username, str(xml_list),
                              str(e), "os.getuid", os.getuid()))

            return("OK")
            
        except Exception, e:
            return log("FAIL: %s fails (%s)" % (my_name(), str(e)))

    # -----------------------------------------------------------------------
    def thredds_unpub_reqdir(self, username, reqdir):
        """
        Unpublish the files mentioned in a request directory's
        catalog.txt from THREDDS.
        """
        try:
            log("--- %s(%s) called by %s" % (my_name(), reqdir, username))
            try:
                catalog_txt = "%s/%s/catalog.txt" % (LANDING_PAD, reqdir)
                self.thredds_xref(username, catalog_txt, False)

                flist = ["%s/1/%s" % (THREDDS_ROOT, x.strip())
                         for x in contents(catalog_txt, False)]
                log("calling rm_filelist(%s)" % str(flist))
                rm_filelist(flist)

            except Exception, e:
                return log("FAIL: %s(%s) fails (%s; %s = %d)"
                           % (my_name(), reqdir, str(e), "os.getuid", os.getuid()))

            return("OK")
            
        except Exception, e:
            return log("FAIL: %s fails (%s)" % (my_name(), str(e)))

    # -----------------------------------------------------------------------
    def thredds_xref(self, username, catlist, add=True):
        """
        Call CatalogXref to add or remove references to the items in
        catlist. If add is True, the references are to be added. If
        add is False, they are removed. CatalogXref is idempotent so
        if the reference is already present, a second copy will not be
        added. If the item is not present, a remove operation will
        have no effect.
        """
        try:
            log("--- %s(%s) called by %s" % (my_name(), catlist, username))
            os.environ['CLASSPATH'] = "%s/build" % scigest_home() \
                                      + ":%s/resources" % scigest_home()
            log("CLASSPATH = '%s'" % os.getenv('CLASSPATH'))
            cmd = ["/usr/local/java/bin/java",
                   "-Djava.ext.dirs=%s/lib/fetched/runtime" % scigest_home(),
                   "scigest.core.CatalogXref",
                   catlist,
                   "file://%s/catalog.xml" % THREDDS_ROOT]
            if not add:
                cmd.append("remove")
            log("running '%s'" % " ".join(cmd))
            proc = subprocess.Popen(cmd,
                                    stdout=subprocess.PIPE,
                                    stderr=subprocess.STDOUT)
            result = "".join(proc.stdout.readlines())
            for line in result.split("\n"):
                log(line)
            log("back from calling CatalogXref")
                
            if has_java_exception(result):
                return log("FAIL: Java threw exception")
                
            return("OK")
                
        except Exception, e:
            return log("FAIL: %s fails (%s)" % (my_name(), str(e)))

# ---------------------------------------------------------------------------
def assume_identity(user, group):
    """
    Set the process identity to user and group.
    """
    p = pwd.getpwnam(user)
    g = grp.getgrnam(group)
    os.setgid(g.gr_gid)
    os.setuid(p.pw_uid)
    os.environ['HOME'] = p.pw_dir
    
# ---------------------------------------------------------------------------
def auth_read_thredds(url, username, password):
    """
    Perform an authenticated read on the THREDDS server at url as
    username/password.
    """
    tauth_realm = "THREDDS Data Server"
    auth_handler = urllib2.HTTPBasicAuthHandler()
    auth_handler.add_password(realm=tauth_realm,
                              uri=url,
                              user=username,
                              passwd=password)
    opener = urllib2.build_opener(auth_handler)

    urllib2.install_opener(opener)
    try:
        handle = urllib2.urlopen(url)
        page = handle.read()
        handle.close()
    except Exception, e:
        if "maximum recursion depth" in str(e):
            raise StandardError("bad password for %s" % url)
        else:
            log(tb.format_exc())
            return
    return page

# ---------------------------------------------------------------------------
def cfgset(key, value):
    """
    Set a config value in $HOME/.scigest/my.properties
    """
    home = os.environ['HOME']
    myprop = "%s/.scigest/my.properties" % home
    log("setting '%s' to '%s' in %s" % (key, value, myprop))
    f = open(myprop, 'w')
    f.write("%s = %s\n" % (key, value))
    f.close()

# # ---------------------------------------------------------------------------
# def has_java_exception(longstr):
#     """
#     Return True if longstr contains a Java exception, otherwise False.
#     """
#     exception_signature = "Exception(: | in )"
#     q = re.findall(exception_signature, longstr)
#     return(q != [])

# ---------------------------------------------------------------------------
def launch_dir():
    return os.path.dirname(os.path.abspath(sys.argv[0]))

# ---------------------------------------------------------------------------
def log(msg):
    """
    Write a log message with a timestamp.
    """
    global logf

    now = time.strftime("%Y.%m%d %H:%M:%S")

    if msg == '@reset':
        logf = setup_logging()
        return msg
    
    try:
        logf.info(msg)
    except:
        logf = setup_logging()
        logf.info(msg)

    return msg

# ---------------------------------------------------------------------------
def setup_logging():
    logf = logging.getLogger("xrpubd_logger")
    logf.setLevel(logging.DEBUG)
    if not os.path.exists(LOGDIR):
        os.makedirs(LOGDIR)
    fh = logging.handlers.RotatingFileHandler(LOGFILE,
                                              maxBytes = 10 * 1024 * 1024,
                                              backupCount = 5)
    fmt = logging.Formatter("%(levelname)-8s:%(asctime)s - %(message)s")
    fh.setFormatter(fmt)
    logf.addHandler(fh)
    return logf

# ---------------------------------------------------------------------------
def c_make_reqdir(dirname):
    if not os.path.exists("%s/%s" % (LANDING_PAD, dirname)):
        make_reqdir(dirname)

# ---------------------------------------------------------------------------
def make_reqdir(dirname):
    lpad = '/tmp/esg/lpad'
    dirpath = '%s/%s' % (lpad, dirname)
    os.mkdir(dirpath)
    f = open('%s/catalog.txt' % dirpath, 'w')
    f.write('foobar.xml\n')
    f.close()

    f = open('%s/foobar.xml' % dirpath, 'w')
    f.writelines(['<?xml version="1.0" encoding="UTF-8"?>\n',
                  '<catalog xmlns="http://www.unidata.ucar.edu/namespaces/thredds'
                  + '/InvCatalog/v1.0"'
                  + ' xmlns:xlink="http://www.w3.org/1999/xlink"'
                  + ' xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"'
                  + ' xsi:schemaLocation="http://www.unidata.ucar.edu/namespaces'
                  + '/thredds/InvCatalog/v1.0'
                  + ' http://www.unidata.ucar.edu/schemas/thredds'
                  + '/InvCatalog.1.0.2.xsd"'
                  + ' name="TDS Configuration File" version="1.0.1">\n',
                  '      <service name="HTTPServer" serviceType="HTTPServer" '
                  + 'base="/thredds/fileServer/">\n',
                  '          <property name="requires_authorization"'
                  + ' value="true" />\n',
                  '          <property name="application" value="Web Browser" />\n',
                  '          <property name="application" value="Web Script" />\n',
                  '      </service>\n',
                  '      <property name="catalog_version" value="2" />\n',
                  '      <dataset name="ornl.test.arm" ID="ornl.test.arm.v1"'
                  + ' restrictAccess="esg-user">\n',
                  '          <property name="dataset_id" value="ornl.test.arm" />\n',
                  '          <property name="dataset_version" value="1" />\n',
                  '          <property name="project" value="test" />\n',
                  '          <property name="model" value="generic" />\n',
                  '          <property name="institute" value="ORNL" />\n',
                  '          <property name="time_frequency"'
                  + ' value="unspecified" />\n',
                  '      </dataset>\n',
                  '</catalog>\n'])
    f.close()

# ---------------------------------------------------------------------------
def my_name():
    """
    Return the caller's function name.
    """
    return sys._getframe(1).f_code.co_name

# ---------------------------------------------------------------------------
def perm_checks():
    """
    Make sure we can create and write files and directories everywhere
    we need to.
    """
    places = [{'path': "%s/1" % THREDDS_ROOT,
               'perm': os.R_OK | os.W_OK | os.X_OK},
              {'path': "%s/catalog.xml" % THREDDS_ROOT,
               'perm': os.R_OK | os.W_OK},
              # {'path': ESG_DATAROOT,
              #  'perm': os.R_OK | os.X_OK | os.W_OK},
              {'path': LOGDIR,
               'perm': os.R_OK | os.X_OK | os.W_OK},
              {'path': "%s" % LOGDIR,
               'perm': os.R_OK | os.W_OK}]
    for item in places:
        if not os.access(item['path'], item['perm']):
            raise StandardError("Insufficient access on path '%s'" % item['path'])
    
# ---------------------------------------------------------------------------
def rm_filelist(flist):
    """
    Remove the files in flist if they exist.
    """
    for fpath in flist:
        if os.path.isfile(fpath):
            log("os.unlink(%s)" % fpath)
            os.unlink(fpath)
            
# ---------------------------------------------------------------------------
class xrpubd(Daemon):
    """
    This class provides for daemonizing the program into the background.
    """
    # -----------------------------------------------------------------------
    def run(self):
        """
        Here we fire up the XML/RPC server.
        """
        try:
            # Create server
            server = SimpleXMLRPCServer((HOST, PORT),
                                        requestHandler=xrpub_handler,
                                        logRequests=False,
                                        allow_none=True,
                                        bind_and_activate=False)
            server.allow_reuse_address = True
            server.server_bind()
            server.server_activate()
            server.register_introspection_functions()
            server.register_instance(xrpubd_callables())

            # Run the server's main loop
            log('@reset')
            log("-" * 60)
            me = pwd.getpwuid(os.getuid())
            log("xrpubd is listening as %s:%s at %s:%s"
                % (me.pw_name, grp.getgrgid(me.pw_gid)[0], 
                   HOST, PORT))
            server.serve_forever()

        except Exception, e:
            log("xrpubd.run fails: '%s'" % str(e))

# ---------------------------------------------------------------------------
class Xrpubd(unittest.TestCase):

    # -----------------------------------------------------------------------
    def test_hopt(self):
        """
        -h reports options
        """
        cmd = "%s/xrpubd.py -h" % launch_dir()
        S = pexpect.spawn(cmd)
        S.expect(pexpect.EOF)
        assert("Options:" in S.before)
        assert("--debug" in S.before)
        assert("--test" in S.before)
        assert("--verbose" in S.before)
        assert("--quiet" in S.before)

    # -----------------------------------------------------------------------
    def test_list_reqdirs(self):
        """
        Calling list_reqdirs() returns a list of known request directories.
        """
        c_make_reqdir('testor.2011.1201.090807')
        c_make_reqdir('testor.2011.1217.192432')
        x = xrpubd_callables()
        rdl = x.list_reqdirs('testor')
        assert('testor.2011.1201.090807' in ''.join(rdl))
        assert('testor.2011.1217.192432' in ''.join(rdl))
        assert('foobar.xml' in ''.join(rdl))
        assert('tpb.2011.1229.084850' not in ''.join(rdl))
        shutil.rmtree('%s/testor.2011.1201.090807' % LANDING_PAD)
        shutil.rmtree('%s/testor.2011.1217.192432' % LANDING_PAD)

    # -----------------------------------------------------------------------
    def test_logging(self):
        """
        log messages go to the expected file.
        """
        log('message from test_logging')
        d = contents(LOGFILE, False)
        self.assertEqual('message from test_logging' in d[-1], True)
        s = os.stat(LOGFILE)
        now = time.time()
        self.assertEqual(abs(s[stat.ST_MTIME] - now) < 1.0, True)

# ---------------------------------------------------------------------------
if __name__ == "__main__":
    main(sys.argv)

